Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

kvserver: add TestFlowControlSendQueueRangeRelocate test #135570

Merged
merged 1 commit into from
Nov 26, 2024

Conversation

kvoli
Copy link
Collaborator

@kvoli kvoli commented Nov 18, 2024

Add a flow control integration test
TestFlowControlSendQueueRangeRelocate. The test has 6 variations, either transferring or not transferring the lease ontop:

We three relocate variations (*=lh,^=send_queue):
- [n1*,n2 ,n3^,n4 ,n5] -> [n2 ,n3^,n4 ,n5 ,n6*] (transfer_lease)
  - The leader and leaseholder is relocated.
- [n1*,n2 ,n3^,n4 ,n5] -> [n1*,n2 ,n4 ,n5 ,n6 ]
  - The replica with a send queue is relocated.
- [n1*,n2 ,n3^,n4 ,n5] -> [n1*,n2 ,n3^,n4 ,n6 ]
  - The replica without a send queue is relocated.

Part of: #132614
Release note: None

@kvoli kvoli self-assigned this Nov 18, 2024
Copy link

blathers-crl bot commented Nov 18, 2024

Your pull request contains more than 1000 changes. It is strongly encouraged to split big PRs into smaller chunks.

🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is dev-inf.

@kvoli kvoli added the backport-24.3.x Flags PRs that need to be backported to 24.3 label Nov 18, 2024
@cockroach-teamcity
Copy link
Member

This change is Reviewable

@kvoli kvoli force-pushed the 241118.rac-send-queue-relocate-test branch 2 times, most recently from 160b25e to 19a8a6a Compare November 19, 2024 22:51
@kvoli
Copy link
Collaborator Author

kvoli commented Nov 19, 2024

I'm missing a variation here that relocates the replica towards a store which the leaseholder has a send queue for, but not for the range (because it doesn't yet have a replica on that store). It doesn't fit too neatly into this test, so I may hack in something to double check it works as expected then defer it to a later PR.

@kvoli kvoli requested a review from sumeerbhola November 19, 2024 23:01
@kvoli kvoli marked this pull request as ready for review November 19, 2024 23:01
@kvoli kvoli requested a review from a team as a code owner November 19, 2024 23:01
Copy link
Collaborator

@sumeerbhola sumeerbhola left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

haven't finished reading, but pushing some questions about the testdata files.

Reviewed 6 of 7 files at r1.
Reviewable status: :shipit: complete! 0 of 0 LGTMs obtained (waiting on @kvoli)


pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_leader_store line 84 at r1 (raw file):
same question as above

After transfer, n6 should initially have a send-queue for n3 with 1 entry. Since no tokens have been consumed, this should be sent and appear in the tracker. And so the send-queue should be empty but 1 entry should be tracked. What am I missing?


pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_has_token_store_transfer_lease line 79 at r1 (raw file):



-- Observe the total tracked tokens per-stream on new leaseholder n6.

After transfer, n6 should initially have a send-queue for n3 with 1 entry. Since no tokens have been consumed, this should be sent and appear in the tracker. And so the send-queue should be empty but 1 entry should be tracked. What am I missing?


pkg/kv/kvserver/flow_control_integration_test.go line 4923 at r1 (raw file):

// prevention and flushing via selective (logical) admission of entries and token
// return. It also exercises the behavior of the send queue when a range is
// relocated. See the initial comment for an overview of the test structure.

(note to self) stopped here


pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_leader_store line 62 at r1 (raw file):

--   before=[0 1 2 3 4]
--   after =[5 1 2 3 4]
-- Transferring the lease false.

won't the lease get transferred anyway since the leaseholder is being removed? Just trying to understand -- I'm not saying that we should remove this variant.


pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_has_token_store line 84 at r1 (raw file):



-- Observe the total tracked tokens per-stream on new leaseholder n1.

new leaseholder? It's the same leaseholder, yes?

@kvoli kvoli requested a review from sumeerbhola November 25, 2024 22:08
Copy link
Collaborator Author

@kvoli kvoli left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewable status: :shipit: complete! 0 of 0 LGTMs obtained (waiting on @sumeerbhola)


pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_has_token_store line 84 at r1 (raw file):

Previously, sumeerbhola wrote…

new leaseholder? It's the same leaseholder, yes?

It is the same leaseholder, its an artifact of the test structure. I'll push a change to exclude the second print here if the lease didn't move.


pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_has_token_store_transfer_lease line 79 at r1 (raw file):

Previously, sumeerbhola wrote…

After transfer, n6 should initially have a send-queue for n3 with 1 entry. Since no tokens have been consumed, this should be sent and appear in the tracker. And so the send-queue should be empty but 1 entry should be tracked. What am I missing?

First of all, thanks for catching this. I don't actually know why this is happening, it appears that the replica gets the queued entry sent to it without any corresponding token deduction or return from the new leaseholder/leader n6, prior to n6 creating a replica send stream towards s3.

Relevant logs:

# 1 MiB write to develop send queue.
I241125 21:46:12.124574 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 818  ‹(Sending 1 MiB put request to develop a send queue)›
I241125 21:46:12.124779 72 kv/kvserver/kvflowcontrol/rac2/range_controller.go:850 ⋮ [T1,Vsystem,n1] 819  r74/1 admitted request (pri=normal-priwait-duration=1.75µs wait-for-all=false)

# Corresponding token deductions and tracking on n1.
I241125 21:46:12.125196 935 kv/kvserver/replica_proposal_buf.go:926 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 820  bound index/log terms for proposal entry: ‹6/33 EntryNormal <omitted>I241125 21:46:12.125250 935 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 821  tracking+1.0 MiBflow control tokens for pri=NormalPri stream=t1/s1log-position=6/33
I241125 21:46:12.125293 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 822  adjusted send flow tokens (wc=regular stream=t1/s1delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:12.125337 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 823  adjusted eval flow tokens (wc=regular stream=t1/s1delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:12.125375 935 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 824  tracking+1.0 MiBflow control tokens for pri=NormalPri stream=t1/s2log-position=6/33
I241125 21:46:12.125407 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 825  adjusted send flow tokens (wc=regular stream=t1/s2delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:12.125448 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 826  adjusted eval flow tokens (wc=regular stream=t1/s2delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:12.125501 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 827  adjusted eval flow tokens (wc=elastic stream=t1/s3delta=-1.0 MiBflag=normal›): regular=+0 Belastic=-3.0 MiBI241125 21:46:12.125563 935 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 828  tracking+1.0 MiBflow control tokens for pri=NormalPri stream=t1/s4log-position=6/33
I241125 21:46:12.125595 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 829  adjusted send flow tokens (wc=regular stream=t1/s4delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:12.125629 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 830  adjusted eval flow tokens (wc=regular stream=t1/s4delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:12.125691 935 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 831  tracking+1.0 MiBflow control tokens for pri=NormalPri stream=t1/s5log-position=6/33
I241125 21:46:12.125719 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 832  adjusted send flow tokens (wc=regular stream=t1/s5delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:12.125805 935 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 833  adjusted eval flow tokens (wc=regular stream=t1/s5delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiB# Admitted on all nodes except 3
I241125 21:46:12.129688 938 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2123 ⋮ [T1,Vsystem,n1] 856  r74:(n2,s2):2 stream t1/s2admit term:6, admitted:[LowPri:33,NormalPri:33,AboveNormalPri:33,HighPri:33] returned send:NormalPri:+1.0 MiB eval:NormalPri:+1.0 MiB
I241125 21:46:12.353456 940 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2123 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 862  r74:(n1,s1):1 stream t1/s1admit term:6, admitted:[LowPri:33,NormalPri:33,AboveNormalPri:33,HighPri:33] returned send:NormalPri:+1.0 MiB eval:NormalPri:+1.0 MiB
I241125 21:46:12.650124 930 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2123 ⋮ [T1,Vsystem,n1] 865  r74:(n5,s5):5 stream t1/s5admit term:6, admitted:[LowPri:33,NormalPri:33,AboveNormalPri:33,HighPri:33] returned send:NormalPri:+1.0 MiB eval:NormalPri:+1.0 MiB
I241125 21:46:12.805797 931 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2123 ⋮ [T1,Vsystem,n1] 868  r74:(n4,s4):4 stream t1/s4admit term:6, admitted:[LowPri:33,NormalPri:33,AboveNormalPri:33,HighPri:33] returned send:NormalPri:+1.0 MiB eval:NormalPri:+1.0 MiB

# Relocate happens here
I241125 21:46:13.241297 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 882-- Issuing RelocateRange:›
I241125 21:46:13.241297 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 882 +--   before=[0 1 2 3 4]›
I241125 21:46:13.241297 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 882 +--   after =[5 0 1 2 3]›
I241125 21:46:13.241297 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 882 +-- Transferring the lease: true.›
I241125 21:46:13.247153 935 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 914  creating send stream t1/s6for replica (n6,s6):6LEARNER
I241125 21:46:13.261469 940 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1013  closing send stream t1/s5for replica (n5,s5):5LEARNER
I241125 21:46:13.262111 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1502 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1026  r74 closing range controller
I241125 21:46:13.262122 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1027  closing send stream t1/s2for replica (n2,s2):2
I241125 21:46:13.262133 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1030  closing send stream t1/s3for replica (n3,s3):3
I241125 21:46:13.262145 936 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-
I241125 21:46:13.262202 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1035  closing send stream t1/s4for replica (n4,s4):4
I241125 21:46:13.262211 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1036  closing send stream t1/s6for replica (n6,s6):6
I241125 21:46:13.262220 936 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2526 ⋮ [T1,Vsystem,n1,s1,r74/1:‹/{Table/Max-Max}›,raft] 1037  closing send stream t1/s1for replica (n1,s1):1

# Raft messages between the relocate start and here that involve n3.
I241125 21:46:13.268683 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1045   [raft] r74 Raft message6->3 MsgVote Term:7 Log:6/42I241125 21:46:13.273685 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1051   [raft] r74 Raft message3->6 MsgVoteResp Term:7 Log:0/0# n6 creates range controller after being given the lead (and lease via a joint cfg).
# Note here that n6 is sending messages to n3 without tracking/deducting tokens for them. Later, when the put
# request is sent to the post-relocated range, it does track the entries.
I241125 21:46:13.273739 5970 kv/kvserver/kvflowcontrol/rac2/range_controller.go:673 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1052  r74 creating range controller
I241125 21:46:13.273765 5970 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1053  creating send stream t1/s6for replica (n6,s6):6
I241125 21:46:13.273928 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1055   [raft] r74 Raft message6->3 MsgApp Term:7 Log:6/42 Commit:42 Entries:[7/43 EntryNormal <omitted>]›
I241125 21:46:13.274028 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1058   [raft] r74 Raft message3->6 MsgAppResp Term:7 Log:6/42 Rejected (Hint: 32) Commit:32I241125 21:46:13.274143 5971 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1060  creating send stream t1/s1for replica (n1,s1):1
I241125 21:46:13.275635 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1065   [raft] r74 Raft message3->6 MsgAppResp Term:7 Log:0/42 Commit:42I241125 21:46:13.275658 5976 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1066  creating send stream t1/s3for replica (n3,s3):3
I241125 21:46:13.275893 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1067   [raft] r74 Raft message6->3 MsgApp Term:7 Log:6/42 Commit:42I241125 21:46:13.275911 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1068   [raft] r74 Raft message6->3 MsgApp Term:7 Log:6/42 Commit:42 Entries:[›
I241125 21:46:13.275911 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1068 +7/43 EntryNormal <omitted>I241125 21:46:13.275911 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1068 +7/44 EntryNormal <omitted>I241125 21:46:13.275911 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1068 +‹]›
I241125 21:46:13.276180 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1069   [raft] r74 Raft message3->6 MsgAppResp Term:7 Log:0/44 Commit:42I241125 21:46:13.276180 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1069   [raft] r74 Raft message3->6 MsgAppResp Term:7 Log:0/44 Commit:42I241125 21:46:13.276315 8952 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n3] 1072   [raft] r74 Raft message6->3 MsgApp Term:7 Log:7/44 Commit:44I241125 21:46:13.276424 5973 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1078  creating send stream t1/s4for replica (n4,s4):4
I241125 21:46:13.276446 9058 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1079   [raft] r74 Raft message3->6 MsgAppResp Term:7 Log:0/44 Commit:44I241125 21:46:13.276456 8914 kv/kvserver_test/client_raft_helpers_test.go:104 ⋮ [T1,Vsystem,n6] 1080   [raft] r74 Raft message1->6 MsgAppResp Term:7 Log:0/44 Commit:44I241125 21:46:13.276468 5973 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2158 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1081  creating send stream t1/s2for replica (n2,s2):2

# Issuing post-relocate put at n6 the new leaseholder.
I241125 21:46:13.277437 72 kv/kvserver_test/flow_control_integration_test.go:5614 ⋮ [-] 1094  ‹(Sending 1 MiB put request to the relocated range)›
I241125 21:46:13.277854 72 kv/kvserver/kvflowcontrol/rac2/range_controller.go:850 ⋮ [T1,Vsystem,n6] 1095  r74/6 admitted request (pri=normal-priwait-duration=541ns wait-for-all=false)
I241125 21:46:13.277966 5980 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1097  tracking+1.0 MiBflow control tokens for pri=NormalPri stream=t1/s1log-position=7/45
I241125 21:46:13.277979 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1098  adjusted send flow tokens (wc=regular stream=t1/s1delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:13.277992 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1099  adjusted eval flow tokens (wc=regular stream=t1/s1delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:13.278009 5980 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1100  tracking+1.0 MiBflow control tokens for pri=NormalPri stream=t1/s2log-position=7/45
I241125 21:46:13.278022 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1101  adjusted send flow tokens (wc=regular stream=t1/s2delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:13.278036 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1102  adjusted eval flow tokens (wc=regular stream=t1/s2delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:13.278055 5980 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1103  tracking+1.0 MiBflow control tokens for pri=NormalPri stream=t1/s3log-position=7/45
I241125 21:46:13.278065 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1104  adjusted send flow tokens (wc=regular stream=t1/s3delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:13.278077 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1105  adjusted eval flow tokens (wc=regular stream=t1/s3delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:13.278101 5980 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1106  tracking+1.0 MiBflow control tokens for pri=NormalPri stream=t1/s4log-position=7/45
I241125 21:46:13.278112 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1108  adjusted send flow tokens (wc=regular stream=t1/s4delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:13.278126 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1110  adjusted eval flow tokens (wc=regular stream=t1/s4delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiBI241125 21:46:13.278142 5980 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1111  tracking+1.0 MiBflow control tokens for pri=NormalPri stream=t1/s6log-position=7/45
I241125 21:46:13.278154 5980 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1114  adjusted send flow tokens (wc=regular stream=t1/s6delta=-1.0 MiBflag=normal›): regular=+3.0 MiBelastic=+1.0 MiB

pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_leader_store line 62 at r1 (raw file):

Previously, sumeerbhola wrote…

won't the lease get transferred anyway since the leaseholder is being removed? Just trying to understand -- I'm not saying that we should remove this variant.

Yeah it will, its just whether it transfers the lease explicitly via an AdminTransferLease. The relocate logic slightly changes, mostly the the timing of the lease transfer -- whether its to a voter incoming, or to a full voter also.

@kvoli
Copy link
Collaborator Author

kvoli commented Nov 25, 2024

For whatever reason, I'm no longer able to comment on reviewable without it wiping my text (probably the long code comment).

After transfer, n6 should initially have a send-queue for n3 with 1 entry. Since no tokens have been consumed, this should be sent and appear in the tracker. And so the send-queue should be empty but 1 entry should be tracked. What am I missing?
First of all, thanks for catching this. I don't actually know why this is happening, it appears that the replica gets the queued entry sent to it without any corresponding token deduction or return from the new leaseholder/leader n6, prior to n6 creating a replica send stream towards s3.

s3 enters StateSnapshot iiuc, this is how it sidesteps tracking the entry:

I241125 22:27:38.893185 6008 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1057 ⋮ [T1,Vsystem,n6,s6,r74/6:‹/{Table/Max-Max}›,raft] 1270  r74 handling raft event: term=0 snap=‹<nil>› entries=[] msgApps=map[] replicaStateInfo=map[1:{StateProbe 0 44} 2:{StateReplicate 44 45} 3:{StateSnapshot 0 44} 4:{StateProbe 0 44} 6:{StateReplicate 44 45}] msgAppMode=‹1›
...
I241125 22:27:38.895093 9150 kv/kvserver/replica_raftstorage.go:521 ⋮ [T1,Vsystem,n3,s3,r74/3:‹/{Table/Max-Max}›] 1288  applied snapshot d816383e from (n6,s6):6 at applied index 44 (total=1ms data=1.9 KiB excise=true ingestion=6@0ms)

@sumeerbhola
Copy link
Collaborator

s3 enters StateSnapshot iiuc, this is how it sidesteps tracking the entry

Ah yes, this makes sense. Since s6 is a new replica it doesn't have the raft log entries from the previous put -- it was created using a snapshot after the put. So a replica with a send-queue can only be caught up with a snapshot. I wonder if we will start seeing more snapshotting due to this behavior. It would be nice to have the ability to delegate the sending of entries, akin to delegated snapshots. Should I create an issue?

Copy link
Collaborator

@sumeerbhola sumeerbhola left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

:lgtm:

Reviewed 1 of 7 files at r1.
Reviewable status: :shipit: complete! 1 of 0 LGTMs obtained (waiting on @kvoli)


pkg/kv/kvserver/testdata/flow_control_integration_v2/send_queue_range_relocate_from_has_token_store line 84 at r1 (raw file):

Previously, kvoli (Austen) wrote…

It is the same leaseholder, its an artifact of the test structure. I'll push a change to exclude the second print here if the lease didn't move.

sounds good


pkg/kv/kvserver/flow_control_integration_test.go line 4923 at r1 (raw file):

Previously, sumeerbhola wrote…

(note to self) stopped here

done

@kvoli kvoli force-pushed the 241118.rac-send-queue-relocate-test branch from 19a8a6a to 2fd7fdd Compare November 26, 2024 14:14
Add a flow control integration test
`TestFlowControlSendQueueRangeRelocate`. The test has 6 variations,
either transferring or not transferring the lease on-top:

```
We use three relocate variations (*=lh,^=send_queue):
- [n1*,n2 ,n3^,n4 ,n5] -> [n2 ,n3^,n4 ,n5 ,n6*] (transfer_lease)
  - The leader and leaseholder is relocated.
- [n1*,n2 ,n3^,n4 ,n5] -> [n1*,n2 ,n4 ,n5 ,n6 ]
  - The replica with a send queue is relocated.
- [n1*,n2 ,n3^,n4 ,n5] -> [n1*,n2 ,n3^,n4 ,n6 ]
  - The replica without a send queue is relocated.
```

Part of: cockroachdb#132614
Release note: None
@kvoli kvoli force-pushed the 241118.rac-send-queue-relocate-test branch from 2fd7fdd to 07ce9fd Compare November 26, 2024 16:21
@kvoli
Copy link
Collaborator Author

kvoli commented Nov 26, 2024

Rebased to resolve merge conflicts.

@kvoli
Copy link
Collaborator Author

kvoli commented Nov 26, 2024

Extended CI failure is on bench. TYFTR!

bors r=sumeerbhola

@kvoli kvoli removed the backport-24.3.x Flags PRs that need to be backported to 24.3 label Nov 26, 2024
@craig craig bot merged commit aded21f into cockroachdb:master Nov 26, 2024
22 of 23 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants